/**
 * 
 */
package com.deep.test.parallel;

import java.util.concurrent.BlockingQueue;
import java.util.concurrent.ThreadPoolExecutor;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicLong;
import java.util.logging.Logger;

/**
 * @author hudepin
 *
 *         2017年12月26日下午1:39:16
 */
public class MyExecutor extends ThreadPoolExecutor {
	private final ThreadLocal<Long> startTime = new ThreadLocal<Long>();
	private final Logger log = Logger.getAnonymousLogger();
	private final AtomicLong numTasks = new AtomicLong();
	private final AtomicLong totalTime = new AtomicLong();
	private final ThreadLocal<String> threadName = new ThreadLocal<String>();

	public MyExecutor(int corePoolSize, int maximumPoolSize, long keepAliveTime, TimeUnit unit,
			BlockingQueue<Runnable> workQueue) {
		super(corePoolSize, maximumPoolSize, keepAliveTime, unit, workQueue);
	}

	@Override
	protected void beforeExecute(Thread t, Runnable r) {
		// System.out.println("threadId:[" + Thread.currentThread().getId() +
		// "],threadName:["
		// + Thread.currentThread().getName() + "]");
		super.beforeExecute(t, r);
		log.info(String.format("Thread [%s]: start [%s]", t.getId() +","+t.getName(), r));
		startTime.set(System.currentTimeMillis());
		threadName.set(t.getId() +","+t.getName());
	}

	@Override
	protected void afterExecute(Runnable r, Throwable t) {
		try {
			long endTime = System.currentTimeMillis();
			long taskTime = endTime - startTime.get();
			numTasks.incrementAndGet();
			totalTime.addAndGet(taskTime);
			log.info(String.format("Thread [%s]: end [%s], time=[%s]ms", threadName.get(), r, taskTime));
		} finally {
			super.afterExecute(r, t);
		}
	}

	@Override
	protected void terminated() {
		try {
			log.info(String.format("Terminated:totalTime=[%s]ms, avg time=[%s]ms,",totalTime.get(), totalTime.get() / numTasks.get()));
		} finally {
			super.terminated();
		}
	}

}
